FireLens（Fluent Bit）からCloudWatch Logsへログを送信時、ThrottlingExceptionエラー回避のためログストリーム設定を見直す
Fargateで起動するFireLens（Fluent Bit）のログルーティングでCloudWatch Logsへの送信設定を検証していました。負荷試験時にFireLensコンテナのログにスロットリングエラーのログが記録されました。
本記事ではFluent Bitの設定を見直す箇所、CloudWatch LogsのAPIレート制限についてみていきます。
[error] [output:cloudwatch_logs:cloudwatch_logs.0] PutLogEvents API responded with error='ThrottlingException', message='Rate exceeded for logStreamName webapp' [error] [output:cloudwatch_logs:cloudwatch_logs.0] Failed to send log events [error] [output:cloudwatch_logs:cloudwatch_logs.0] Failed to send events [ warn] [engine] failed to flush chunk '1-1628656770.31314631.flb', retry in 9 seconds: task_id=1, input=forward.1 > output=cloudwatch_logs.0 (out_id=0)
Fluent BitはCloudWatch Logsへ再送を試みているログも確認できます。いずれCloudWatch Logsへ送信できる可能性はあります。しかし、CloudWatch Logsへ送り終わる前にコンテナが停止すると、コンテナ内に保持していたログと共に失います。できれば避けたいです。
結論
2023/1/19追記ログストリームのリクエストクォータに大幅な制限緩和のアップデートが入りました。
今回の原因は単一のログストリームにログを保存していました。ログストリーム単位の制限値を超過しやすい環境にありました。
- CloudWatch LogsのPutLogEvents APIのクォータはログストリーム単位である
- Fluent Bitの設定でコンテナごとに個別のログストリームを作成して保存する
- 個別のログストリーム作成にはECSメタデータの変数を利用すると簡単
設定例
ログストリーム名はwebapp-の後にFireLensが起動したタスクのIDを付与
[OUTPUT]
Name cloudwatch
Match webapp-firelens*
region ap-northeast-1
log_group_name /ecs/logs/variable-test
log_stream_name webapp-$(ecs_task_id) <- ECSメタデータ変数を利用してタスクIDごとのログストリームを作成する
auto_create_group true
実行結果
検証環境
| 項目 | バージョン |
|---|---|
| aws-for-fluent-bit | 2.19.0 |
| Fluent Bit | 1.8.3 |
| Fargate platform | 1.4.0 |
CloudWatch Logsを知る
エラーメッセージ内のキーワードを個別に確認します。
PutLogEvents APIとは
CloudWatch LogsのログストリームにログイベントをアップロードできるAPIです。
Fluent BitからCloudWatch Logsへログを送るのに利用されていました。
ThrottlingException Rate exceededとは
一定時間内に受信可能なAPIリクエスト数を制限しています。その制限値を超過したことを示しています。 一般的にスロットリングエラーを回避するには、APIリクエスト頻度を減らす、APIリクエストの間隔をずらす（同時実行数を減らす）、いい感じの間隔で再試行する（Exponential Backoff）などがあげられます。
今回はどこの制限値を超過してしまったのでしょうか？
CloudWatch Logsのクォータ確認
PutLogEventsリソースのクォータを確認します。2020/8/10現在
- ログストリームごとに1秒間5リクエスト
- リクエストの最大サイズは1MB
- アカウントのリージョンごとに1秒間800トランザクション
- 一部対象外のリージョンあり、1500トランザクション/秒
CloudWatch Logs quotas - Amazon CloudWatch Logs
ログストリーム名webappに対してとメッセージに書いてあり、1秒間5リクエストの制限値を超過した可能性が非常に高いです。復数のFluent Bitから単一のログストリームを指定している状況でした。FireLnesコンテナとログストリームが1対多の関係です。
-
Icons made by Freepik from www.flaticon.com
ログストリーム単位のメトリクスは確認できませんでしたが、ロググループ単位のIncommingLogEventsを確認できました。青い線がアプリケーションコンテナのログイベントで、オレンジ色の線がFireLensコンテナのログイベントです。青い線が値を確認すると桁違いにログイベントが発生していることがわかります。これが単一のログストリームに向いている状況です。
問題のあったFluent Bitの設定
log_stream_nameでwebappと指定しています。
[SERVICE]
Flush 1
Grace 30
[FILTER]
Name grep
Match webapp-firelens*
Exclude log ^(?=.*ELB-HealthChecker\/2\.0).*$
[OUTPUT]
Name cloudwatch
Match webapp-firelens*
region ap-northeast-1
log_group_name /ecs/logs/variable-test
log_stream_name webapp
auto_create_group true
上記設定ですとロググループ名はlog_group_nameで指定した/ecs/logs/variable-testが作成されます。
ログストリームはwebappが1個作成されています。
単一のログストリームに対して復数のFireLens（Fluent Bit）コンテナからPutLogEvents APIのリクエストが発生します。Flushが1秒指定であることもあり、秒間5リクエスト制限は容易に超過しそうです。
Fluent Bitの設定を見直す
FireLens（Fluent Bit）コンテナごとのlog_stream_nameをユニークな名前付けて作成したいです。FireLensコンテナとログストリームが1対1の関係にしログの送信先を分散させます。
-
Icons made by Freepik from www.flaticon.com
aws-for-fluent-bitイメージをECSで実行する場合、ECSのメタデータを利用した変数が用意されています。タスクIDが格納されている変数$(ecs_task_id)を利用してlog_stream_nameを設定します。
[SERVICE]
Flush 1
Grace 30
[FILTER]
Name grep
Match webapp-firelens*
Exclude log ^(?=.*ELB-HealthChecker\/2\.0).*$
[OUTPUT]
Name cloudwatch
Match webapp-firelens*
region ap-northeast-1
log_group_name /ecs/logs/variable-test
log_stream_name webapp-$(ecs_task_id)
auto_create_group true
実行結果
タスクID付きのログストリーム名が作成されるようになりました。タスクごとにログストリームが増えるため、スケールアウトすればその分だけ新しいログストリームが追加されます。
FireLensのログを確認すると、Fluent Bit起動時にタスクIDを付きのログストリーム作成している様子が確認できます。
変数に格納されていたECSメタデータはどこから？
FireLensのコンテナにECS Execして確認してみます。環境変数の中からタスクIDの値は確認できませんでした。
HOSTNAME=ip-10-0-17-186.ap-northeast-1.compute.internal TERM=xterm-256color AWS_CONTAINER_CREDENTIALS_RELATIVE_URI=/v2/credentials/2b568cca-f442-4b52-8e09-30d04887980c AWS_EXECUTION_ENV=AWS_ECS_FARGATE PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin AWS_DEFAULT_REGION=ap-northeast-1 PWD=/ LANG=C.UTF-8 AWS_REGION=ap-northeast-1 SHLVL=1 HOME=/root ECS_CONTAINER_METADATA_URI=http://169.254.170.2/v3/1eade9f9a747448897e7970b8026f77b-1714341083 ECS_CONTAINER_METADATA_URI_V4=http://169.254.170.2/v4/1eade9f9a747448897e7970b8026f77b-1714341083 _=/usr/bin/env
ECS_CONTAINER_METADATA_URIがあったので、curlでアクセスしてみて何の値を取得できるのか確認します。
curl http://169.254.170.2/v3/1eade9f9a747448897e7970b8026f77b-1714341083
com.amazonaws.ecs.task-arnからタスクIDを取得できますね。その他にはクラスター名をcom.amazonaws.ecs.clusterから取得できますね。
{
"DockerId": "1eade9f9a747448897e7970b8026f77b-1714341083",
"Name": "log_router",
"DockerName": "log_router",
"Image": "123456789012.dkr.ecr.ap-northeast-1.amazonaws.com/sample-custom-logrouter-firelens:6b1d27f",
"ImageID": "sha256:b5a9487fead1c815c2bcb8061d8d4003dab0dbbdd37416802b492c0cac48386e",
"Labels": {
"com.amazonaws.ecs.cluster": "arn:aws:ecs:ap-northeast-1:123456789012:cluster/sample-dev-cluster",
"com.amazonaws.ecs.container-name": "log_router",
"com.amazonaws.ecs.task-arn": "arn:aws:ecs:ap-northeast-1:123456789012:task/sample-dev-cluster/1eade9f9a747448897e7970b8026f77b",
"com.amazonaws.ecs.task-definition-family": "sample-dev-webapp-taskdefinition",
"com.amazonaws.ecs.task-definition-version": "12"
},
"DesiredStatus": "RUNNING",
"KnownStatus": "RUNNING",
"Limits": {
"CPU": 2
},
"CreatedAt": "2021-08-09T14:06:30.976767663Z",
"StartedAt": "2021-08-09T14:06:30.976767663Z",
"Type": "NORMAL",
"Networks": [
{
"NetworkMode": "awsvpc",
"IPv4Addresses": [
"10.0.17.186"
]
}
]
}
興味本位で覗いてみた結果、このメタデータから取得した値を利用しているのではないかと思いました。
まとめ
今回の原因は単一ログストリームに復数のFluet Bitからログを送信したためによるものでした。ユニークなログストリーム名を作成するにはFluent Bit設定ファイルでECSメタデータの変数を利用すると手軽です。${ecs_task_id}の他に使えそうな変数として$(uuid)があります。こちらはランダムな英数字を返してくれます。どちらかというとタスクIDの方がタスクに紐付いたログの保存先だと判別しやすいので使いやすいです。
補足
FireLensコンテナ自身のログをCloudWatch Logs（ログドライバー:awslogs指定）へ保存した場合、デフォルト設定でログストリーム名にタスクIDが付与されて作成されます。詳しくは以下のリンクを参照ください。
ECSメタデータの変数は旧プラグインのみ利用できます。詳しく以下のリンクを参照ください。
おわりに
Flushの1秒を伸ばしてPutLogEvents APIをリクエスト頻度を下げるのも手です。副作用としてはFireLensコンテナ内でログを保持している時間が長くなります。コンテナ停止した際にログを失う量も増える可能性はあります。FireLensコンテナ内にログを溜め込まずCloudWatch Logsへ早めに送り永続化してほしくなります。
